Change typespec_client_core::http::policies::logging Request and Response log level to debug#3643
Conversation
|
Thank you for your contribution @jlaundry! We will review the pull request and get back to you soon. |
When I originally added the logging policy, I wanted the traces to be a higher visibility than the random noise of debugging so developers could see the HTTP operations without the debug spew from the service client. But I do see your point. One possible refinement (and possible feature creep) would be to make the debug level be configurable in the logging client options and then have identity use the debug logging level and other SDKs use Info. But that's probably overkill. |
It's valid. But other high-volume activity (i.e., regular polling of a Queue, pushing data to an Event Hub, sending traces to Log Analytics, etc.) may also need to be excluded, so we would probably end up the other way round, with Info as the option. In most production deployment cases, unless there was a specific issue we were trying to diagnose, I would typically expect applications to run at Info level, and not see upstream API activity unless they ran with (I'm trying to think of counter examples, low-volume operations where you may want verbose logging to know exact timestamps of when something was done: KeyVault signing/decryption operations, database schema changes, maybe DNS changes... but in all those cases, I'd expect the application to be logging those events as well.) |
There was a problem hiding this comment.
Pull request overview
This PR reduces default log noise from typespec_client_core’s HTTP logging policy by downgrading routine request/response trace messages from INFO to DEBUG, which is particularly relevant for azure_identity token refresh traffic.
Changes:
- Switch request logging from
tracing::info!totracing::debug!. - Switch successful response logging from
tracing::info!totracing::debug!. - Update
tracingimports accordingly.
Comments suppressed due to low confidence (1)
sdk/core/typespec_client_core/src/http/policies/logging.rs:52
- With the request log now at
debug!, whennext[0].send(...)returnsErrthe info-level logs no longer include the request method/headers (only the URL and error from the"<== Failed response"branch). This makes diagnosing transient transport/auth failures harder at the default info level. Consider either (a) logging the request at info only when the response isErr, or (b) including the request method (and optionally sanitized headers) in the existing info-level failed-response log message so failures still have enough context without reintroducing routine token-refresh noise.
debug!(
"==> Request: url: {}, method: {}, headers: {{ {} }}",
request.url.sanitize(&self.allowed_query_params),
request.method(),
request.headers().sanitize(&self.allowed_headers)
);
|
/azp run rust - pullrequest |
|
Azure Pipelines successfully started running 1 pipeline(s). |
|
/checkenforcer evaluate |
|
/check-enforcer evaluate |
|
/check-enforcer help |
|
For help using check enforcer, see https://aka.ms/azsdk/checkenforcer Available commands:
If you are initializing a new service, follow the new service docs. If no Azure Pipelines are desired, run |
|
/check-enforcer evaluate |
Signed-off-by: Jed Laundry <jlaundry@jlaundry.com>
0b1c414 to
a4e5c24
Compare
When using
azure_identity, applications see Request and Response INFO log events as access tokens are refreshed, sometimes hourly(ish):Since
azure_identitydoesn't do much logging, these appear out of the blue; and apart from failures, these aren't very useful.This PR downgrades these logs to
debug, consistent with the Python SDK.I did consider a more complete PR, and the Failed response case: and either holding off logging the Request (not ideal), or re-log the Request as info... but for every use-case I can think of, the only useful info is the Timestamp and X-MS-Request-ID headers for raising a support case, both which are both in the Response anyway.